Skip to content

wifi, ble: fix cooperative-scheduler bugs and cut scheduler/interrupt overhead by 10x - #59

Open
deadprogram wants to merge 9 commits into
mainfrom
wifi-improvements
Open

wifi, ble: fix cooperative-scheduler bugs and cut scheduler/interrupt overhead by 10x#59
deadprogram wants to merge 9 commits into
mainfrom
wifi-improvements

Conversation

@deadprogram

@deadprogram deadprogram commented Jul 29, 2026

Copy link
Copy Markdown
Member

This branch takes the findings from the recent BLE bring-up and applies them to the WiFi path, on
the premise that both are the same problem: an ESP-IDF blob written for preemptive FreeRTOS running
under TinyGo's cooperative scheduler. It fixes one outright functional failure (BLE central GATT),
removes several latent memory- and interrupt-level bugs, cuts the scheduler's wasted work by an
order of magnitude on all three targets, and adds the instrumentation that made those numbers
measurable in the first place.

  • BLE central GATT now works: espradio_vhci_write waits for the controller to actually take
    each HCI packet, ending the duplicate-transmission that made service discovery time out on the
    ESP32-C3.
  • The Xtensa WiFi interrupt storm is gone: an unackable level-triggered line was re-firing
    45,146 times per second on an idle scan; throttled unmasking brings that to ~985/s with no loss
    of MAC servicing.
  • Scheduler passes dropped from 27,599/s to 1,180/s on C3 (and 45,144 → 2,177 on S3) by
    rate-limiting the wake feedback loop the blob's own yields were driving.
  • Three real memory bugs fixed: the ROM pointer snapshot was pinning pointers to NULL on every
    pass, ESP32's ISR tables in .wifibss were never zeroed so the NULL guard was inert, and the
    fifth semaphore ever created panicked against a four-slot pool shared with the BT controller.
  • Frame handling is now correct rather than merely non-crashing: oversize RX frames are dropped
    instead of silently truncated into corrupt ones, and TX retries against the TX-done signal
    instead of discarding the frame on the first ESP_ERR_NO_MEM.
  • ~130 lines of C deleted by moving the VHCI RX ring and most of lib.c into Go, with the
    existing tests passing unmodified and the binary slightly smaller.
  • ReadStats() exposes the driver's counters, several of which were being maintained with no
    reader at all, so future regressions in these paths are visible instead of inferred. (thanks to @soypat for the rename suggestion)

Everything here was verified on hardware:

  • scan and apwebserver on C3, S3 and ESP32,
  • BLE peripheral and central on the C3

Measured on hardware

Target Metric Before After
C3 passes/sec 27,599 1,180
S3 passes/sec 45,144 2,177
S3 hwisr/sec 45,146 985
ESP32 passes/sec 27,183 2,170
ESP32 hwisr/sec ~27,000 983

What remains open:

  • unlatched our_tx_eb on C3 AP mode
  • an unexercised TX retry path
  • BLE-derived 10 ms clamp still imposed on WiFi's queues

Several plausible-sounding changes were tried and then dropped because their own counters refuted them, so the diff is smaller than the investigation behind it. I ran so many hardware tests!

@soypat soypat left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I can't speak for the code itself. C bindings are above my paygrade.

Comment thread radio.go Outdated
Comment thread radio.go Outdated
Comment thread radio.go Outdated
Comment thread radio.go Outdated
@soypat

soypat commented Jul 29, 2026

Copy link
Copy Markdown
Contributor

Be nice to get some actual performance numbers

@deadprogram

Copy link
Copy Markdown
Member Author

Be nice to get some actual performance numbers

Always true. But keep in mind this PR is mostly about removing errors in the original implementation, many of which that caused a lot of extra spinning for no good reason. Most of these due to my misunderstanding how certain signals are supposed to work on ESP32xx. The BLE implementation surfaced a number of these, hence this draft-status PR to incorporate those corrections on the WiFi side.

@deadprogram

Copy link
Copy Markdown
Member Author

I have handled your feedback items @soypat thanks. Any more, or anyone else have anything?

Base automatically changed from ble-again-july to main July 29, 2026 20:44
Diagnostic groundwork for the ESP32-C3 central/GATT failure. This does not fix
it -- scanning and advertising are unaffected and still work.

Symptom: as a central, service discovery succeeds but characteristic discovery
returns nothing ("could not find heart rate characteristic"), or the link drops
outright with reason 0x3e (Connection Failed to be Established). Back-to-back
runs of the same binary alternate between the two.

Both modes share one cause. ke_event_schedule / rw_schedule run in two contexts:
the 5 ms scheduler tick calls them directly, and the BT controller task reaches
them via modules_funcs[0x284], which sits outside rw_schedule()'s own
g_waking_sleeping_sem guard. Event handlers yield (the HCI-to-host path does),
so the two contexts either

  - race, delivering one ACL packet to the host twice. That shifts the ATT
    request/response stream permanently out of step: every response is consumed
    as the answer to the previous request, so service discovery silently
    re-reads the same handle range and characteristic discovery parses a stale
    ReadByGroupResponse and finds nothing; or

  - starve the task, so connection events are not serviced in time and the peer
    drops the link.

Added here:

- vhci_host_recv_cb: compare-only duplicate detector, logging just on a hit so
  normal timing is undisturbed (full tracing perturbs the link enough to change
  which failure mode occurs). This is what established the duplicate originates
  at the controller boundary rather than in the host stack's framing.

- Split BT_TICK_KE_PUMP into BT_TICK_KE_PUMP (ke_event_schedule) and
  BT_TICK_KE_TASK (ke_task_schedule) so each half can be enabled independently
  while bisecting.

- espradio_semphr_take: document that a zero-timeout take is a mutual-exclusion
  guard rather than a scheduling point, and why the yield on the failure path
  cannot simply be removed (doing so starves the controller task and drops the
  link).

Configurations measured, none of them correct:

  tick drives everything + yield   link holds, duplicates, chars fail
  no tick rwip_schedule, no yield  no duplicates, link drops
  tick idle (task owns scheduler)  no duplicates, HCI never dispatches at all
  re-entrancy guard on 0x284       link drops; a sticky flag across a yielding
                                   dispatch blocks ke events entirely

The fix is to make the controller task the sole owner of the scheduler. That is
blocked on identifying what drives ke_task_schedule in a stock ESP-IDF build,
since with the tick idle the task's rw_schedule path never dispatches ke
messages and HCI output never reaches the host. modules_funcs[0x284] is the
entry to identify first.

Signed-off-by: deadprogram <[email protected]>
…packet

espradio_vhci_write handed a packet to the ROM controller and returned
immediately. The controller has a single HCI input slot, and under the
cooperative scheduler nothing runs it between two back-to-back writes -- the
5 ms tick is far away.

The host stack sends LE_Set_Advertising_Enable via sendWithoutResponse, which
does not wait for the Command Complete, and then on the Connect ->
DiscoverServices path emits the first ATT request ~200 us later, both out of
its single scratch buffer. The second write reached the slot before the
controller had read the first, so:

  - the Command Complete for 0x200a never arrived, and
  - the controller, signalled twice but finding the ATT request both times,
    transmitted that request twice -- two Number-Of-Completed-Packets events
    for one write.

The peer received a duplicated request, never answered it, and service
discovery timed out.

bt_pump_hci() now runs after each send: it wakes btdm_controller_task, which
blocks on a semaphore and so is not reached by a yield alone, and drives the
event dispatcher until notify_host_send_available fires.
API_vhci_host_check_send_available() cannot serve as the completion signal --
it reports capacity and is already true immediately after a send, so polling
it returns at once without the controller having run.

This also drops the scheduler-contention scaffolding added in 169ae79.
Instrumenting that guard showed its deferral counter stay at 0 for entire runs
while GATT still failed: the 5 ms tick and the controller task never actually
overlap. Removing the modules_funcs[0x284] hook changes nothing, and the
duplicate-delivery detector it came with memcmp'd every received packet to
chase the same wrong theory. For the record, that slot holds r_rwip_schedule
(0x400014a4), not r_ke_event_schedule (0x40000df8) as its comment claimed.

Verified on an ESP32-C3 against a BlueZ peer:

  - heartrate-monitor, unmodified: scan, connect, discover, subscribe, and a
    continuous notification stream with no disconnect
  - discover: 4 services, characteristics enumerated, reads returning data
  - peripheral mode unaffected: a host central discovers 0x180d, negotiates
    MTU 248 and reads 0x2a38

The ble.go hunk is gofmt only; fmt-check has been failing since 169ae79.

Signed-off-by: deadprogram <[email protected]>
The BLE bring-up (698a5fe..d5d094a) produced findings that are not BLE-specific:
they follow from running a blob written for preemptive FreeRTOS under a cooperative
scheduler, which is equally true of the WiFi path. Wait on a signal the blob can
only set by having run, never on a delay or a capacity query. Make the primitives
the blob treats as critical sections real. Instrument first, and let the counters
refute you.

Instrumentation
---------------

DebugStats() exposes the driver's counters, including several that existed with no
callers at all: espradio_isr_ring_drops was declared and defined but never read
from Go, and espradio_alloc_stats likewise. bt_malloc/bt_free now route through
espradio_malloc/free so the alloc totals cover both users of the shared arena.
espradio_event_loop_run_once returns whether it dispatched, so a drain loop can
tell "queue empty" from "out of passes". espradio_tx_done_noop counts the blob's
TX-done callback instead of discarding it. SetSchedPolicy and SetKickThrottleUs
make the two behaviours worth measuring switchable at runtime.

Bugs fixed
----------

ROM pointer snapshot was actively destructive. espradio_save_rom_ptrs() captured
all five pointers unconditionally after a fixed 40 scheduler passes; measured, at
least one is still NULL then on C3 and S3. Worse, postWiFiStart() runs from both
Start() and StartAP(), so the first call's NULL snapshot made
espradio_restore_rom_ptrs() pin those pointers to NULL on every later pass -- which
is why the second call's 40 passes never saw them become valid. Each pointer now
latches independently, the first time it is non-NULL; NULL is never captured and
never restored.

Xtensa interrupt storm. Several WiFi sources are routed onto one level-triggered
CPU interrupt and the blob registers exactly one handler (slots 1, installed 1), so
WIFI_BB asserts with nothing to ack it. Unmasking at the end of every pass re-fired
it immediately: 45,146 interrupts per second on examples/scan, which passes no
traffic. espradio_wifi_unmask() now re-enables that line at most once per 1000 us.
Safe because these handlers service nothing -- they mask and wake the scheduler,
and schedOnce() calls espradio_call_wifi_isr() itself every pass, so the MAC is
serviced whether or not the interrupt fired.

Uninitialised ISR tables on ESP32. s_isr_fn/s_isr_arg live in .wifibss, which the
runtime does not zero, so every entry read as a valid handler and the NULL guard in
the dispatcher was inert. Zeroed at Enable().

RX frames were truncated to the caller's buffer rather than dropped. The ring holds
1600 bytes against a 1522-byte consumer, and a short frame is not a smaller version
of the original but a corrupt one. vhci_ring_test.go documented this same bug class
for the VHCI ring and named this fix.

TX dropped the frame on the first ESP_ERR_NO_MEM, with the error discarded by
netlink. It now retries against the TX-done signal, on the shape
espradio_vhci_write ended up with: single-writer gate, pump rather than yield,
bounded, counted. Note TX-done fires for blob-originated frames too, so it means "a
buffer was released", not "our frame went out".

Scheduler wake feedback loop. Every espradio_task_yield_go called kickSched, and
the ticker selects on that channel, so the blob's yields set the scheduler's rate --
27,599 passes per second against a nominal 200. Now rate-limited to 1 kHz, with the
real-hardware-interrupt path left unthrottled, the same split bt_wake_task_throttled
uses.

Cooperative core. schedOnce() declines to nest rather than letting a bring-up pump
overlap the ticker and unmask the WiFi interrupt mid-pass. osi.c's queue spinlocks
yield, since on one cooperative core a holder in another goroutine can only run if
we do -- event_lock() already did, and the inconsistency was the bug. safeGosched()
reports whether it yielded, and the four loops that spin on it fail instead of
hanging; espradio_mutex_lock() gained a timeout where it had none.
espradio_wifi_int_disable/restore is rebuilt on bt_interrupt_disable's shape, with
nesting inside the primitive and unbalanced restores ignored. The RX ring fences
before publishing. Semaphore slots are reclaimed via the CAS bitmap mutexes already
used, so the fifth semaphore ever created no longer panics against a pool of four
shared with the BT controller. Enable() is guarded and no longer re-lays the arena
under a live BT controller. s_in_hw_isr distinguishes hardware interrupt context
from "blob ISR body running", which s_in_isr conflates on S3/ESP32; and s_bt_in_isr,
which nothing ever assigned, is now maintained, so bt_is_in_isr() stops answering
about the WiFi poll.

Measured on hardware
--------------------

                        before    after
  C3    passes/sec      27,599    1,180
  S3    passes/sec      45,144    2,177
  S3    hwisr/sec       45,146      985
  ESP32 passes/sec      27,183    2,170
  ESP32 hwisr/sec      ~27,000      983

Refuted by their own counters, and dropped
------------------------------------------

Draining the scheduler's work sources until idle: the cap-hit counters stay at zero,
so four passes is always enough. Honouring block_time_tick in espradio_queue_send:
no send is ever rejected. Both counters stay as regression detectors.

schedOnce re-entrancy and the safeGosched failure paths never trigger either --
kept as safety nets, not as fixes for observed problems, and commented as such.
Scan's 250 ms settle is named but not replaced: the ticker runs continuously in the
background, so the blob is not waiting on us there and a pump cannot shorten
wall-clock settling. The rx handler's error is counted rather than propagated,
because IngressEthernet reports one for any frame the stack declines -- 38 of 101
received -- which is ordinary traffic, not a device failure.

Three attempts at the storm failed before the working one: dropping WIFI_BB,
restoring it, and detaching it to ETS_INVALID_INUM. The last silenced the storm and
still crashed at a byte-identical PC, which resolved inside TinyGo's
handleInterrupt: that dispatches CPU interrupts 6 through 30, so ETS_INVALID_INUM,
6 on Xtensa, is a live line here rather than the nowhere it is under ESP-IDF. All
three errors came from treating an ESP-IDF constant and a cross-target comparison
as authoritative for a runtime that dispatches interrupts differently.

Still open: our_tx_eb and our_wait_eb never latch on the C3 in AP mode, so they get
no DMA-corruption protection (harmless only because unlatched now means unrestored);
the TX retry and oversize-drop paths are unexercised at these traffic levels; and
the 10 ms clamp in espradio_queue_recv remains a BLE fix imposed on WiFi's queues.

Verified
--------

fmt-check, unit-test, and smoke-test (13 examples x 3 targets) pass.

On hardware: scan and apwebserver on ESP32-C3, ESP32-S3 and ESP32, and BLE on the
C3 -- heartrate and heartrate-monitor -- throughout, since osi.c, radio.go, isr.c
and bt_ble.c are all shared with the controller.

Signed-off-by: deadprogram <[email protected]>
@deadprogram
deadprogram marked this pull request as ready for review July 29, 2026 20:46
@deadprogram deadprogram changed the title wifi: apply the BLE lessons to the cooperative core wifi: improve cooperative core Jul 29, 2026
@deadprogram

Copy link
Copy Markdown
Member Author

I can't speak for the code itself. C bindings are above my paygrade.

This is a problem I am trying to do something about that right this moment, at least a little bit...please stand by...

@soypat

soypat commented Jul 29, 2026

Copy link
Copy Markdown
Contributor

Really wish we had tinygo-org/cesp which just wrapped the raw C bindings so vetting and reviewing was more straightforward. Right now I have no clue of what is going on.

Also: What is the underying issue this is trying to solve? Was performance slow? Issues in latency? If this is about the scheduler being hit "too often" we could just hold off until after the conference. Looking at the code just rings every alarm in my head...

@soypat

soypat commented Jul 29, 2026

Copy link
Copy Markdown
Contributor

Also there's a 5MB binary in repo? What is it used for? Do 5MB binaries even fit on a esp32?

@deadprogram

Copy link
Copy Markdown
Member Author

Also there's a 5MB binary in repo? What is it used for? Do 5MB binaries even fit on a esp32?

Umm, have you ever looked at this repo before? 😸 All joking aside It is patterned after the embedded rust project's implementation. You need these blobs for linking to ROM functions that do all the radio real work.

@soypat

soypat commented Jul 30, 2026

Copy link
Copy Markdown
Contributor

The 5MB blob is new though, was not here before or had a different path. Saw it pop up during git pull

vhci_ring.c held a single-producer/single-consumer byte ring and nothing else: no
dependency on the BTDM blob, no hardware access. vhci_ring.go existed purely to
call into it, and vhci_ring_test.go already covered it through that wrapper.
Making the Go file the implementation deletes both the C and the pass-through
layer; the eight tests pass unmodified, which is the evidence the semantics did
not move.

bt_ble.c still calls espradio_vhci_ring_push, now resolved to an //export from Go.
Its build tag is esp32c3 and the Go file's is esp32c3 || esp32c3_qemu_target, so
the definition always exists wherever the caller does.

runtime/volatile, not sync/atomic
---------------------------------

The first version used sync/atomic for the head and tail indices. That is not the
equivalent of the C volatile it replaced. The C3 is RV32IMC with no atomic
extension -- TinyGo's targets/esp32c3.json feature string is
"+32bit,+c,+m,+zmmul,-relax" -- so atomic.LoadUint32/StoreUint32 lower to
__atomic_load_4/__atomic_store_4, and src/runtime/atomics_critical.go implements
those by masking interrupts around the access.

Those calls sat in the per-byte loops, three per byte in vhciReadByte, and in the
push path that runs in the controller's recv callback. On hardware, BLE
notifications on a central (heartrate-monitor) arrived with human-noticeable
pauses, while a peripheral (heartrate) looked healthy because its inbound HCI rate
is far lower. runtime/volatile is what the C had -- a plain load/store the
compiler may not cache in a register, no call, no masking -- and
single-writer-per-index is what makes that sufficient.

That first version also batched index publication to once per push and once per
read. Wrong independently of cost: reading tail once let a push beginning against
a near-full ring give up while the consumer was actively draining, and on an HCI
byte stream a short push is a truncated packet, not a slow one. Both sides
publish per byte again, as the C did.

Size, same program, against the C it replaces:

                        code      bss   push fn
  C                   268916    41504         -
  Go, sync/atomic     269020    41504     138 B
  Go, volatile        268884    41504      92 B

Verified
--------

fmt-check and unit-test pass, with vhci_ring_test.go unmodified. smoke-test
builds 11 examples x 3 targets clean.

On hardware, ESP32-C3: heartrate and heartrate-monitor both work; apwebserver
still works on C3, S3 and ESP32.

Still open: one run showed heartrate-monitor notifications stalling unless the
peripheral was close, which did not reproduce on a reflash of the same tree. It
is unexplained rather than fixed. Neither this ring nor the lib.c change can
affect RX sensitivity, and PHY calibration is not the gap (the NVS stub returns
ESP_ERR_NOT_FOUND, so cal_mode falls through to PHY_RF_CAL_FULL every boot) --
but a marginally misaligned receive window would present exactly as
distance-dependent, and central-path timing has its own history here.

Signed-off-by: deadprogram <[email protected]>
@deadprogram

Copy link
Copy Markdown
Member Author

The 5MB blob is new though, was not here before or had a different path. Saw it pop up during git pull

That was after #54 when the ESP32 was added to the already existing blobs in the repo for ESP32C3 and ESP32S3.

This removes nearly all of the C functions in lib.c now that
they have been moved into Go where they really belong.

Signed-off-by: deadprogram <[email protected]>
@deadprogram

Copy link
Copy Markdown
Member Author

Was able to get rid of some C code and push those parts into Go code covered by tests. In particular vhci_ring.go allowed deleting vhci_ring.c entirely.

@deadprogram deadprogram changed the title wifi: improve cooperative core wifi, ble: fix cooperative-scheduler bugs and cut scheduler/interrupt overhead by 10x Jul 30, 2026
@deadprogram

Copy link
Copy Markdown
Member Author

I have updated the title and description of this PR so it better explains what it does, and why we really need it. Once this is in place, any future refactoring and additions will be greatly helped by actually calling the blob functions they way they were meant to be called. 🔧

@soypat

soypat commented Jul 30, 2026

Copy link
Copy Markdown
Contributor

How does this PR affect heap growth?

espradio_alloc_stats() had no callers at all before this branch, so nothing ever
answered whether the shared arena grows over a long run. These two examples
sample AllocCount, FreeCount, ArenaUsed and ArenaCapacity against a post-warmup
baseline and report the drift, which is what makes a leak in either the WiFi blob
or the BT controller visible rather than inferred. Both also watch the counters
that should stay at zero -- cap hits, ring drops, queue-full, RxOversize, a
leaked IntsOffNesting -- and print a line only when one moves, so a clean
overnight run stays quiet.

soak drives the radio with repeated scans. It needs no AP and no network, and
scan is the allocation-heaviest single operation the blob has, which makes it the
one to run first. soak-traffic connects through netlink and fetches a URL on a
loop instead, putting frames through the TX and RX paths. They are separate
examples rather than one binary with a mode switch because linking net/http into
the scan soak took it from 472 KB to 1198 KB of code for no benefit.

The two share their reporting block verbatim. A shared package under examples/
would break smoke-test, whose loop builds every immediate subdirectory as a main
package, and examples are better read standalone; diff the two files if they ever
drift.

Measured on an ESP32-C3, roughly 19 minutes each
------------------------------------------------

No growth in either mode. The scan soak sawtooths -- a scan in flight holds a few
hundred bytes -- but every trough returns to exactly 30024 B and 28 outstanding.
The traffic soak never moves off 30808 B and 34 at all, because the HTTP path
allocates on the Go heap and in the blob's TX buffers rather than the arena.
Scheduler rates were 1197 and 1211 passes/s against the 1180 this branch claims,
with hwisr/s at 2 and 24.

Three things the run corrected in the first draft of these files:

- RxDrops does not belong in the quiet list. About 28% of inbound frames were
  dropped on a full RX ring, steadily, on an ordinary LAN -- 1361 of 4796. Every
  fetch still succeeded, since TCP retransmits what the ring loses, so it is a
  capacity signal rather than a fault, and treating it as should-stay-zero made
  the quiet line fire on every sample and bury the counters that do mean
  something. It is reported as a share on the rx line instead.

- The share is over RxCallbacks alone. espradio_sta_rxcb increments it before
  testing the ring, so drops are a subset; dividing by callbacks plus drops
  counted them twice and read 22% instead of 28%.

- TxDoneCB does not run well ahead of TxAttempts, as it was documented to. It sat
  at exactly two ahead for the whole run, presumably association and EAPOL at
  connect. The blob evidently sends little of its own once associated.

Neither soak validates the NO_MEM retry path: nomem stayed at 0 across 1127 TX
attempts, so the path this branch added was never reached. The peak line is also
a sampled maximum rather than a true high-water mark, and is documented as a
lower bound -- it crept from +568 to +672 B purely from sampling phase while the
floor held exactly.

Verified
--------

fmt-check and unit-test pass. Both examples build on xiao-esp32c3, xiao-esp32s3
and esp32-mini32.

Signed-off-by: deadprogram <[email protected]>
@deadprogram

deadprogram commented Jul 30, 2026

Copy link
Copy Markdown
Member Author

How does this PR affect heap growth?

I decided that was a very good question to try to answer in a quantitative way. Hence the most recent commit with 2 new examples to measure this.

So here is the result:

How does this PR affect heap growth?

It doesn't grow the heap. It makes heap growth measurable, and the measurement
comes back clean.

Static analysis

Go GC heap: unchanged. No make/new/append, no closures, goroutines, or
channels anywhere in the added driver code. The two files moved from C are
explicitly non-allocating, because they run in blob and interrupt context.

Static RAM: flat. The 2048-byte VHCI ring went from C .bss to Go .bss,
not to the heap — bss measured identical at 41504 before and after in 5baf13c,
with code down 32 bytes.

The shared arena: byte-identical consumption. bt_malloc/bt_free now route
through espradio_malloc/espradio_free, but those wrappers bump a counter and
call the same espradio_arena_alloc underneath. What changed is that the alloc
totals now describe both users of the pool instead of only the WiFi half. The
arena itself is a one-time fixed 48 KB allocation from the Go heap
(arena_pool_default.go), so nothing there grows either.

Measured on an ESP32-C3, ~19 minutes per mode

baseline after 19 min
scan soak 30024 B / 28 outstanding 30024 B / 28 — every trough exactly
traffic soak 30808 B / 34 30808 B / 34 — never moved

The scan soak sawtooths up to +672 B while a scan is in flight, which is
allocation, not growth: the floor is what a leak would raise, and it didn't move
by a byte. The traffic soak doesn't even sawtooth, because HTTP allocates on the
Go heap and in the blob's TX buffers rather than the arena.

Two behavioural changes worth knowing

One genuine leak is fixed, though not on the heap: semaphore slots are now
reclaimed, so the four-slot pool shared with the BT controller no longer runs dry
— previously the fifth semaphore ever created panicked. Unbounded consumption of
a bounded resource is what "heap growth" usually means in practice here.

The TX retry holds memory marginally longer. A NO_MEM frame now waits on the
TX-done signal instead of being dropped, bounded at 4 attempts. It allocates
nothing, and in practice it never fired — 1127 TX attempts, zero NO_MEM.

Limits of the above

A clean soak invites over-reading, so: 19 minutes is not overnight; the NO_MEM
retry path was never reached, so this does not validate it; and WiFi and BLE were
not soaked concurrently, which is where the shared arena would be under the most
pressure.

The PR carries the tooling to re-check any of it — examples/soak needs no
configuration at all.

@deadprogram

deadprogram commented Jul 30, 2026

Copy link
Copy Markdown
Member Author

Here are my actual results.

Details

esp32c3 soak:

$ tinygo flash -target xiao-esp32c3 -size short -monitor ./examples/soak
   code    data     bss |   flash     ram
 472092   20476   69140 |  492568   89616
Connecting to /dev/ttyACM0...
Connected.
Detected chip: ESP32-C3
USB-JTAG/Serial interface detected, disabling watchdogs
Loading stub loader...
Stub running.
Erasing flash...
[##################################################]  100.0%
Flash erased.
Attaching SPI flash...
Configuring flash size...
Auto-detected flash size: 4MB
Flash params set to 0x022F
SHA digest in image updated
Attaching SPI flash...
Switching to 460800 baud...
Running at 460800 baud.
Compressed 492672 bytes to 320315 (65%)
Flash begin: 320315 bytes at 0x00000000 (20 compressed blocks)
[##################################################]  100.0%
Flash complete. Verifying...
MD5 verified: c857a9f0e52b9f09fc8d91eeaad33dc4

Device reset.
Connected to /dev/ttyACM0. Press Ctrl-C to exit.
soak: scan mode
soak 00:00:30  warmup 1/4  arena 30176/49144 B  out 29
soak 00:01:00  warmup 2/4  arena 30384/49144 B  out 31
soak 00:01:30  warmup 3/4  arena 30024/49144 B  out 28
soak 00:02:00  warmup 4/4  arena 30024/49144 B  out 28
soak 00:02:30  BASELINE arena 30024/49144 B  out 28  passes/s 1197  hwisr/s 2
soak 00:03:00  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 13/0
soak 00:03:30  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 15/0
soak 00:04:00  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 17/0
soak 00:04:30  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 19/0
soak 00:05:00  arena 30072/49144 B  out 28  drift +48 B / +0  per hr +1152 B / +0  work 21/0
     peak arena 30072 B (+48)  out 28 (+0)
soak 00:05:30  arena 30384/49144 B  out 31  drift +360 B / +3  per hr +7200 B / +60  work 23/0
     peak arena 30384 B (+360)  out 31 (+3)
soak 00:06:00  arena 30592/49144 B  out 33  drift +568 B / +5  per hr +9737 B / +85  work 25/0
     peak arena 30592 B (+568)  out 33 (+5)
soak 00:06:30  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 28/0
     peak arena 30592 B (+568)  out 33 (+5)
soak 00:07:00  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 30/0
     peak arena 30592 B (+568)  out 33 (+5)
soak 00:07:30  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 32/0
     peak arena 30592 B (+568)  out 33 (+5)
soak 00:08:00  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 34/0
     peak arena 30592 B (+568)  out 33 (+5)
soak 00:08:30  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 36/0
     peak arena 30592 B (+568)  out 33 (+5)
soak 00:09:00  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 38/0
     peak arena 30592 B (+568)  out 33 (+5)
soak 00:09:30  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 40/0
     peak arena 30592 B (+568)  out 33 (+5)
soak 00:10:00  arena 30176/49144 B  out 29  drift +152 B / +1  per hr +1216 B / +8  work 42/0
     peak arena 30592 B (+568)  out 33 (+5)
soak 00:10:30  arena 30488/49144 B  out 32  drift +464 B / +4  per hr +3480 B / +30  work 44/0
     peak arena 30592 B (+568)  out 33 (+5)
soak 00:11:00  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 47/0
     peak arena 30592 B (+568)  out 33 (+5)
soak 00:11:30  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 49/0
     peak arena 30592 B (+568)  out 33 (+5)
soak 00:12:00  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 51/0
     peak arena 30592 B (+568)  out 33 (+5)
soak 00:12:30  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 53/0
     peak arena 30592 B (+568)  out 33 (+5)
soak 00:13:00  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 55/0
     peak arena 30592 B (+568)  out 33 (+5)
soak 00:13:30  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 57/0
     peak arena 30592 B (+568)  out 33 (+5)
soak 00:14:00  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 59/0
     peak arena 30592 B (+568)  out 33 (+5)
soak 00:14:30  arena 30072/49144 B  out 28  drift +48 B / +0  per hr +240 B / +0  work 61/0
     peak arena 30592 B (+568)  out 33 (+5)
soak 00:15:00  arena 30384/49144 B  out 31  drift +360 B / +3  per hr +1728 B / +14  work 63/0
     peak arena 30592 B (+568)  out 33 (+5)
soak 00:15:30  arena 30696/49144 B  out 34  drift +672 B / +6  per hr +3101 B / +27  work 65/0
     peak arena 30696 B (+672)  out 34 (+6)
soak 00:16:00  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 68/0
     peak arena 30696 B (+672)  out 34 (+6)
soak 00:16:30  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 70/0
     peak arena 30696 B (+672)  out 34 (+6)
soak 00:17:00  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 72/0
     peak arena 30696 B (+672)  out 34 (+6)
soak 00:17:30  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 74/0
     peak arena 30696 B (+672)  out 34 (+6)
soak 00:18:00  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 76/0
     peak arena 30696 B (+672)  out 34 (+6)
soak 00:18:30  arena 30024/49144 B  out 28  drift +0 B / +0  per hr +0 B / +0  work 78/0
     peak arena 30696 B (+672)  out 34 (+6)

And for soak-traffic:

$ tinygo flash -target xiao-esp32c3 -ldflags="-X main.ssid=XXXX -X main.password=YYYYYYY -X main.url=http://example.com" -size short -monitor ./examples/soak-traffic/
   code    data     bss |   flash     ram
1197564   36324  116604 | 1233888  152928
Connecting to /dev/ttyACM0...
Connected.
Detected chip: ESP32-C3
USB-JTAG/Serial interface detected, disabling watchdogs
Loading stub loader...
Stub running.
Erasing flash...
[##################################################]  100.0%
Flash erased.
Attaching SPI flash...
Configuring flash size...
Auto-detected flash size: 4MB
Flash params set to 0x022F
SHA digest in image updated
Attaching SPI flash...
Switching to 460800 baud...
Running at 460800 baud.
Compressed 1233984 bytes to 768947 (62%)
Flash begin: 768947 bytes at 0x00000000 (47 compressed blocks)
[##################################################]  100.0%
Flash complete. Verifying...
MD5 verified: 4b5b34407a406475b6e940b9f36b5ac3

Device reset.
Connected to /dev/ttyACM0. Press Ctrl-C to exit.
SHA-256 comparison failed:
Calculated: 239c01b9fa65535fcf8d30583e64a17dd68ddeea3050c8389bec7a8385a8a5ee
Expected: 8e5ba9bdf0bc3b8c6b6b768bc6b14295fc9e33545d65d48a77ff0ca295dd4fb0
Attempting to boot anyway...
entry 0x4039cee0
soak: traffic mode, ssid rems url http://example.com
soak 00:00:30  warmup 1/4  arena 30808/49144 B  out 34
soak 00:01:00  warmup 2/4  arena 30808/49144 B  out 34
soak 00:01:30  warmup 3/4  arena 30808/49144 B  out 34
soak 00:02:00  warmup 4/4  arena 30808/49144 B  out 34
soak 00:02:30  BASELINE arena 30808/49144 B  out 34  passes/s 1211  hwisr/s 24
soak 00:03:00  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 18/0
     tx att 170 nomem 0 retry 0 busy 0 done 172  rx cb 795 ingress-err 364
     QUIET COUNTERS MOVED: rx-drop 173->208
soak 00:03:30  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 21/0
     tx att 198 nomem 0 retry 0 busy 0 done 200  rx cb 914 ingress-err 412
     QUIET COUNTERS MOVED: rx-drop 173->242
soak 00:04:00  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 24/0
     tx att 227 nomem 0 retry 0 busy 0 done 229  rx cb 1036 ingress-err 460
     QUIET COUNTERS MOVED: rx-drop 173->279
soak 00:04:30  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 27/0
     tx att 257 nomem 0 retry 0 busy 0 done 259  rx cb 1162 ingress-err 512
     QUIET COUNTERS MOVED: rx-drop 173->314
soak 00:05:00  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 30/0
     tx att 285 nomem 0 retry 0 busy 0 done 287  rx cb 1244 ingress-err 536
     QUIET COUNTERS MOVED: rx-drop 173->335
soak 00:05:30  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 33/0
     tx att 313 nomem 0 retry 0 busy 0 done 315  rx cb 1431 ingress-err 641
     QUIET COUNTERS MOVED: rx-drop 173->380
soak 00:06:00  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 36/0
     tx att 343 nomem 0 retry 0 busy 0 done 345  rx cb 1589 ingress-err 715
     QUIET COUNTERS MOVED: rx-drop 173->425
soak 00:06:30  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 39/0
     tx att 371 nomem 0 retry 0 busy 0 done 373  rx cb 1707 ingress-err 758
     QUIET COUNTERS MOVED: rx-drop 173->463
soak 00:07:00  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 42/0
     tx att 401 nomem 0 retry 0 busy 0 done 403  rx cb 1832 ingress-err 814
     QUIET COUNTERS MOVED: rx-drop 173->493
soak 00:07:30  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 45/0
     tx att 432 nomem 0 retry 0 busy 0 done 434  rx cb 1952 ingress-err 857
     QUIET COUNTERS MOVED: rx-drop 173->530
soak 00:08:00  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 48/0
     tx att 464 nomem 0 retry 0 busy 0 done 466  rx cb 2085 ingress-err 915
     QUIET COUNTERS MOVED: rx-drop 173->564
soak 00:08:30  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 51/0
     tx att 493 nomem 0 retry 0 busy 0 done 495  rx cb 2197 ingress-err 954
     QUIET COUNTERS MOVED: rx-drop 173->600
soak 00:09:00  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 54/0
     tx att 523 nomem 0 retry 0 busy 0 done 525  rx cb 2309 ingress-err 994
     QUIET COUNTERS MOVED: rx-drop 173->633
soak 00:09:30  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 57/0
     tx att 554 nomem 0 retry 0 busy 0 done 556  rx cb 2440 ingress-err 1049
     QUIET COUNTERS MOVED: rx-drop 173->669
soak 00:10:00  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 60/0
     tx att 585 nomem 0 retry 0 busy 0 done 587  rx cb 2608 ingress-err 1132
     QUIET COUNTERS MOVED: rx-drop 173->714
soak 00:10:30  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 63/0
     tx att 615 nomem 0 retry 0 busy 0 done 617  rx cb 2750 ingress-err 1190
     QUIET COUNTERS MOVED: rx-drop 173->759
soak 00:11:00  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 66/0
     tx att 645 nomem 0 retry 0 busy 0 done 647  rx cb 2846 ingress-err 1222
     QUIET COUNTERS MOVED: rx-drop 173->784
soak 00:11:30  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 69/0
     tx att 673 nomem 0 retry 0 busy 0 done 675  rx cb 2954 ingress-err 1263
     QUIET COUNTERS MOVED: rx-drop 173->814
soak 00:12:00  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 72/0
     tx att 702 nomem 0 retry 0 busy 0 done 704  rx cb 3065 ingress-err 1312
     QUIET COUNTERS MOVED: rx-drop 173->838
soak 00:12:30  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 74/0
     tx att 726 nomem 0 retry 0 busy 0 done 728  rx cb 3171 ingress-err 1344
     QUIET COUNTERS MOVED: rx-drop 173->879
soak 00:13:00  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 77/0
     tx att 750 nomem 0 retry 0 busy 0 done 752  rx cb 3291 ingress-err 1383
     QUIET COUNTERS MOVED: rx-drop 173->926
soak 00:13:30  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 80/0
     tx att 781 nomem 0 retry 0 busy 0 done 783  rx cb 3405 ingress-err 1426
     QUIET COUNTERS MOVED: rx-drop 173->957
soak 00:14:00  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 83/0
     tx att 809 nomem 0 retry 0 busy 0 done 811  rx cb 3516 ingress-err 1472
     QUIET COUNTERS MOVED: rx-drop 173->985
soak 00:14:30  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 86/0
     tx att 838 nomem 0 retry 0 busy 0 done 840  rx cb 3631 ingress-err 1520
     QUIET COUNTERS MOVED: rx-drop 173->1014
soak 00:15:00  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 89/0
     tx att 868 nomem 0 retry 0 busy 0 done 870  rx cb 3744 ingress-err 1563
     QUIET COUNTERS MOVED: rx-drop 173->1045
soak 00:15:30  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 92/0
     tx att 896 nomem 0 retry 0 busy 0 done 898  rx cb 3853 ingress-err 1602
     QUIET COUNTERS MOVED: rx-drop 173->1078
soak 00:16:00  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 95/0
     tx att 925 nomem 0 retry 0 busy 0 done 927  rx cb 3970 ingress-err 1657
     QUIET COUNTERS MOVED: rx-drop 173->1102
soak 00:16:30  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 98/0
     tx att 952 nomem 0 retry 0 busy 0 done 954  rx cb 4091 ingress-err 1695
     QUIET COUNTERS MOVED: rx-drop 173->1149
soak 00:17:00  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 101/0
     tx att 981 nomem 0 retry 0 busy 0 done 983  rx cb 4234 ingress-err 1750
     QUIET COUNTERS MOVED: rx-drop 173->1199
soak 00:17:30  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 104/0
     tx att 1010 nomem 0 retry 0 busy 0 done 1012  rx cb 4350 ingress-err 1786
     QUIET COUNTERS MOVED: rx-drop 173->1241
soak 00:18:00  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 107/0
     tx att 1038 nomem 0 retry 0 busy 0 done 1040  rx cb 4459 ingress-err 1831
     QUIET COUNTERS MOVED: rx-drop 173->1268
soak 00:18:30  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 110/0
     tx att 1068 nomem 0 retry 0 busy 0 done 1070  rx cb 4586 ingress-err 1887
     QUIET COUNTERS MOVED: rx-drop 173->1300
soak 00:19:00  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 113/0
     tx att 1097 nomem 0 retry 0 busy 0 done 1099  rx cb 4663 ingress-err 1910
     QUIET COUNTERS MOVED: rx-drop 173->1316
soak 00:19:30  arena 30808/49144 B  out 34  drift +0 B / +0  per hr +0 B / +0  work 116/0
     tx att 1127 nomem 0 retry 0 busy 0 done 1129  rx cb 4796 ingress-err 1959
     QUIET COUNTERS MOVED: rx-drop 173->1361

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

This PR hardens and instruments the ESP radio integration when running ESP-IDF WiFi/BLE blobs under TinyGo’s cooperative scheduler, addressing observed functional failures (notably BLE central GATT), interrupt/scheduler feedback loops, and several memory/initialization hazards while adding counters and soak tooling to make regressions measurable.

Changes:

  • Reworked scheduler pass policy, throttling, and drain loops to reduce pass/interrupt overhead and make contention observable via new driver stats.
  • Fixed multiple low-level correctness issues (ROM pointer latching/restore behavior, ISR table initialization, semaphore slot reclamation, RX oversize handling, and TX NO_MEM retry behavior).
  • Added driver counter reporting (ReadStats/Print) plus new soak examples and documentation to validate long-run stability on hardware.

Reviewed changes

Copilot reviewed 23 out of 23 changed files in this pull request and generated 1 comment.

Show a summary per file
File Description
vhci_ring.go Moves VHCI RX ring implementation to Go and uses volatile index access to reduce interrupt-masking overhead.
vhci_ring.c Removes the prior C VHCI ring implementation now superseded by Go.
README.md Documents new soak and soak-traffic long-running validation workflows and how to interpret counters.
radio.go Major scheduler policy/throttling/counter work; adds ReadStats/Stats; fixes bring-up pumping, critical-section semantics, semaphore pooling, and task teardown cleanup.
radio_esp32s3.go Adds HW ISR counting in the ESP32-S3 WiFi interrupt handler.
radio_esp32c3.go Marks true HW interrupt context and adds HW ISR counting for ESP32-C3 WiFi ISR path.
radio_esp32.go Adds HW ISR counting in the ESP32 WiFi interrupt handler.
osi.c Makes queue locks yield under cooperative scheduling; adds queue-full counter; exposes espradio_malloc/free for shared allocation accounting; makes event loop drain observable.
netlink/netlink.go Logs RecvAndSend() errors in debug mode to aid diagnosing unrecoverable TX failures.
netif.c Adds TX-done accounting, TX retry-on-NO_MEM with bounded pump passes, RX ring ordering fixes + oversize-drop behavior, and avoids unsafe RX ring resets.
netif_esp.go Treats ingress handler errors as counted diagnostics rather than propagated failures; adds RxIngressErrors counter.
lib.go Replaces many missing libc/IDF symbols with Go implementations (time, sleep/usleep, random, strrchr, WiFi connect/disconnect wrappers).
lib.c Leaves only __assert_func in C; documents moved symbols now implemented in Go.
isr.c Adds ISR table zeroing for .wifibss, richer ISR slot/handler instrumentation, and distinct HW-ISR vs blob-ISR context flags.
examples/soak/main.go New scan-driven long-run soak test for arena drift and “quiet counter” regressions.
examples/soak-traffic/main.go New traffic-driven long-run soak test exercising TX/RX paths and reporting rates/counters.
examples/scan/main.go Prints driver stats alongside scan output to make drops/cap-hits/interrupt storms visible.
espradio.h Adds memory barrier macro, new counter/query APIs, HW-ISR context APIs, and updated event-loop run signature.
esp32s3/isr.c Adds WiFi interrupt unmask rate-limiting to break level-triggered interrupt storms on Xtensa S3.
esp32c3/isr.c Provides stub unmask rate-limit accessors for uniform stats reporting on C3 (no storm expected).
esp32/isr.c Adds WiFi interrupt unmask rate-limiting to break level-triggered interrupt storms on Xtensa ESP32.
bt_ble.c Fixes BT ISR context tracking and routes BLE allocations through WiFi’s accounting wrappers; updates VHCI ring ownership notes.
ble.go Switches VHCI transport reads to Go ring helpers and marks BT dispatch as HW ISR context to prevent unsafe yields.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment thread radio.go Outdated
Review feedback on #59 pointed out that wifiEnabled is set by the CAS at the top
of Enable, so a failure in espradio_wifi_init leaves it at 1 and every later
Enable returns ErrAlreadyEnabled. That much is correct: wifiEnabled was written
in exactly one place and never reset, and there is no Disable or deinit anywhere
in the tree.

Neither suggested fix works here, though.

Setting the flag only after a successful init would open a hole rather than close
one. The CAS is not just recording state, it is the mutual-exclusion guard, and
Enable yields partway through -- the ticker settle is a real scheduling point
under cooperative scheduling. Move the latch to the end and a second caller
arriving during that sleep runs the whole body concurrently, re-registering the
CPU interrupt and re-entering blob init. Both NetConnect and the AP path call
Enable, so that is a reachable state, and it is worse than a stuck flag.

Reverting the partial setup on the error path is the right shape but has nothing
to build on. By the time the blob init can fail, the ISR tables are zeroed, the
arena is laid out, the ticker goroutine is running with no way to stop it, the
CPU interrupt is registered and prioritised, the routing is prewired, the event
callback is registered and the HAL clocks are up. None of that has teardown code,
and without an esp_wifi_deinit binding the blob cannot be put back either. A
partial unwind would leave a half-initialised radio that reports itself ready.

So the failure stays terminal, and what changes is that it says so. wifiEnabled
becomes three-state -- off, on, failed -- and every error return in Enable goes
through enableFailed(), which records the terminal state on the way out. A caller
that retries now gets ErrEnableFailed, "earlier Enable failed, reset required",
instead of being told the radio is already enabled and sent looking in the wrong
place. The CAS stays exactly where it was.

enableFailed is a package-level function rather than a closure inside Enable, so
the init path does not allocate where it does not have to.

Also here: Enable now checks initHardware's error instead of discarding it,
matching BLEInit, which has always checked it. Every target returns nil today, so
this is a guard against a future one that does not rather than a fix for an
observed failure.

Verified
--------

fmt-check, unit-test and smoke-test (13 examples x 3 targets) pass.

On hardware, ESP32-C3: scan and apwebserver, plus heartrate and heartrate-monitor
on the BLE side, since Enable shares initHardware and the arena with BLEInit.

Signed-off-by: deadprogram <[email protected]>

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Copilot reviewed 23 out of 23 changed files in this pull request and generated no new comments.

Comments suppressed due to low confidence (2)

lib.go:51

  • The comment says both sleep and usleep “round up to at least one tick”, but sleep() currently passes secs*100 straight through. For secs==0 this becomes a zero-tick delay, which contradicts the comment and can reintroduce busy-spin behaviour if the blob uses sleep(0) as a yield point.
// sleep and usleep both round up to at least one tick: the blob uses them as
// yield points, and a zero-tick delay would spin.

//export sleep
func sleep(secs uint32) uint32 {
	espradio_task_delay(secs * 100)
	return 0

osi.c:174

  • This comment implies that in “real interrupt context” it’s acceptable to spin on these locks. If a HW ISR ever contends with a preempted goroutine that holds s_queues_lock/q->lock, spinning will deadlock (the goroutine can’t run until the ISR returns). It would be safer to document that these locks must not be taken/contended in HW ISR context, rather than suggesting spinning is a viable fallback.
 * In real interrupt context there is no goroutine to yield from, so spin instead.
 * That case tests espradio_in_hw_isr() rather than the blob-facing _is_from_isr,
 * which is also true when the blob's ISR body runs on the scheduler goroutine. */

@soypat

soypat commented Jul 30, 2026

Copy link
Copy Markdown
Contributor

Two things I don't understand:

  • Did you do any before/after comparison of heap usage, or just current heap usage?
  • Are the statistics you print even of the Go GC or are they ESP32 specific coprocessor statistics? I'm interested in Go GC statistics. You assert "Go GC heap: unchanged" and yet it seems as though you've provided zero evidence of this if this is non-GoGC stats, from what I can grep from your wall of text

@deadprogram

Copy link
Copy Markdown
Member Author

This PR is about fixing errors in the original implementation. And not impacting the heap in any new way that was not already happening.

@deadprogram

deadprogram commented Jul 30, 2026

Copy link
Copy Markdown
Member Author

@soypat I tried your suggestion to add some Go memory logging to the webserver example:

EDIT(soypat): results
	go func() {
		for {
			time.Sleep(10 * time.Second)
			var m runtime.MemStats
			runtime.ReadMemStats(&m)
			println("Memory usage: Alloc =", m.Alloc, "TotalAlloc =", m.TotalAlloc, "Sys =", m.Sys)
		}
	}()

Here is the current main branch:

$ tinygo flash -target xiao-esp32c3 -ldflags="-X main.ssid=XXXX -X main.password=YYYYYYYY" -size short -monitor ./examples/webserverlog                                                                                                                                                                                                                                                                                                
   code    data     bss |   flash     ram                                                                 
1191730   38016  118184 | 1229746  156200                                                                 
Connecting to /dev/ttyACM0...                                                                             
Connected.                                                                                                
Detected chip: ESP32-C3                                                                                   
USB-JTAG/Serial interface detected, disabling watchdogs                                                                        
Loading stub loader...                                                                                                         
Stub running.                                                                                                                  
Erasing flash...                                                                                                               
[##################################################]  100.0%                                                                   
Flash erased.                                                                                                                  
Attaching SPI flash...                                                                                                         
Configuring flash size...                                                                                                      
Auto-detected flash size: 4MB                                                                                                  
Flash params set to 0x022F                                                                                                     
SHA digest in image updated                                                                                                    
Attaching SPI flash...                                                                                                         
Switching to 460800 baud...                                                                                                                                    
Running at 460800 baud.                                                                                                                                        
Compressed 1229840 bytes to 777454 (63%)                                                                                                                       
Flash begin: 777454 bytes at 0x00000000 (48 compressed blocks)                                                                                                 
[##################################################]  100.0%                                                                                                   
Flash complete. Verifying...                                                                                                                                   
MD5 verified: d304e929d6a19ebe458f4f4d8621c4da                                                                                                                 

Device reset.                                                                                                                                                  
Connected to /dev/ttyACM0. Press Ctrl-C to exit.                                                                                                               
SHA-256 comparison failed:                                                                                                                                     
Calculated: d648179c6582719eabef23aa743cf701742d5a5ed05551a682f2c36e95cc1424                                                                                   
Expected: b380776a879185b19e475e1d4f08ec396eeeb0a9025c9394ce65844b41af836d                                                                                     
Attempting to boot anyway...                                                                                                                                   
entry 0x4039d544                                                                                                                                               
Connecting to WiFi...                                                                                                                                          
HTTP server listening on http://192.168.1.167:80                                                                                                               
Memory usage: Alloc = 123952 TotalAlloc = 121865 Sys = 201184                                                                                                  
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
Memory usage: Alloc = 162800 TotalAlloc = 591000 Sys = 201184                                                                                                  
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /                                                                                                                                                          
GET /favicon.ico                                                                                                                                               
GET /cnt                                                                                                                                                       
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /                                                                                                                                                          
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                                                               
Memory usage: Alloc = 183952 TotalAlloc = 1603893 Sys = 201184                                                                                                 
Memory usage: Alloc = 183952 TotalAlloc = 1603893 Sys = 201184 

Here is from the PR branch:

$ tinygo flash -target xiao-esp32c3 -ldflags="-X main.ssid=XXXX -X main.password=YYYYYY" -size short -monitor ./examples/webserverlog                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
   code    data     bss |   flash     ram                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                   
1193642   38028  118628 | 1231670  156656                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                   
Connecting to /dev/ttyACM0...                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                               
Connected.                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
Detected chip: ESP32-C3                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     
USB-JTAG/Serial interface detected, disabling watchdogs                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     
Loading stub loader...                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
Stub running.                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                               
Erasing flash...                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            
[##################################################]  100.0%                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                
Flash erased.                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                               
Attaching SPI flash...                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
Configuring flash size...                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                   
Auto-detected flash size: 4MB                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                               
Flash params set to 0x022F                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
SHA digest in image updated                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
Attaching SPI flash...                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
Switching to 460800 baud...                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
Running at 460800 baud.                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     
Compressed 1231776 bytes to 778838 (63%)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
Flash begin: 778838 bytes at 0x00000000 (48 compressed blocks)
[##################################################]  100.0%  
Flash complete. Verifying...
MD5 verified: f0b4cc699342c5debb74bd39bb93b232
                                                               
Device reset.   
Connected to /dev/ttyACM0. Press Ctrl-C to exit.
SHA-256 comparison failed:
Calculated: c34f95b8f8216dc1eb36dad14cdb41c4aa7fc23bfbea761316ad2a201f255f2f                                                                                                         
Expected: 28c03342347fbb6b37598b99343c21a74a763da6081e07e36cfa38fa9fe3a22d                                                                                                           
Attempting to boot anyway...                                                                                                                                   
entry 0x4039d628                                                                                                                                                                                                                                                                                                              
Connecting to WiFi...                                                                                                                                                                                                                                         
HTTP server listening on http://192.168.1.167:80              
Memory usage: Alloc = 124064 TotalAlloc = 121961 Sys = 200956 
GET /                                                                                                                                                          
GET /cnt                                                                                                                       
GET /favicon.ico         
Memory usage: Alloc = 162912 TotalAlloc = 202259 Sys = 200956
GET /                                                          
GET /favicon.ico                                                                                                                                                                                                                                                                                                              
GET /                                                                                                                                                                                                                                                         
GET /cnt                                 
GET /favicon.ico                                             
GET /                        
GET /cnt               
GET /favicon.ico                                       
GET /                                                  
GET /cnt              
GET /favicon.ico
GET /                                                       
GET /cnt                                                    
GET /                 
GET /cnt                 
GET /favicon.ico             
GET /                        
GET /favicon.ico           
GET /                      
GET /cnt                   
GET /favicon.ico           
GET /                                   
GET /cnt                                                      
GET /                                                         
GET /cnt                                                    
GET /favicon.ico                              
GET /                                                          
GET /cnt                                                       
GET /favicon.ico                                
GET /                                           
GET /cnt                                                                                                                                                       
GET /favicon.ico                                                                                                               
Memory usage: Alloc = 172128 TotalAlloc = 833551 Sys = 200956                                                                  
GET /                       
GET /cnt             
GET /favicon.ico                                
GET /                                                        
GET /cnt                                                     
GET /favicon.ico
GET /           
GET /cnt        
GET /favicon.ico
GET /           
GET /cnt        
GET /favicon.ico
GET /           
GET /cnt                                                      
GET /                                                         
GET /cnt                                                       
GET /favicon.ico
GET /                                                                          
GET /cnt                                                                       
GET /favicon.ico                                                               
GET /                                                                          
GET /cnt                                                                       
GET /favicon.ico                                                               
GET /                                                                          
GET /cnt                                                                       
GET /favicon.ico                                                               
GET /                                                                          
GET /cnt                                                                       
GET /favicon.ico                                                               
GET /                                                                                     
GET /favicon.ico                                                                          
GET /                                                                                     
GET /favicon.ico                                                                          
GET /                                                                                     
GET /cnt                                                                                  
GET /favicon.ico                                                                          
GET /                                                                                     
GET /cnt                                                                                  
GET /favicon.ico                                                                          
GET /                                                                                     
GET /cnt                                                                                  
GET /favicon.ico                                                                          
GET /                                                                                     
GET /cnt                                                                                  
GET /favicon.ico                                                                          
Memory usage: Alloc = 183936 TotalAlloc = 1699682 Sys = 200956                            
GET /                                                                                                     
GET /cnt                                                                                                  
GET /favicon.ico                                                                                          
GET /                                                                                                     
GET /cnt                                                                                                  
GET /favicon.ico                                                                                          
GET /                                                                                                     
GET /cnt                                                                                                  
GET /favicon.ico                                                                                          
Memory usage: Alloc = 162784 TotalAlloc = 1874870 Sys = 200956                                            
Memory usage: Alloc = 162784 TotalAlloc = 1874870 Sys = 200956

@soypat

soypat commented Jul 30, 2026

Copy link
Copy Markdown
Contributor

These results show webserver allocations, which would eclipse everything else including the diff of this PR (I would hope, since they allocate 10kB per request)

@deadprogram

Copy link
Copy Markdown
Member Author

OK, I used examples/http-app with GC sampling:

Go GC impact of wifi-improvements — measurement results

Question. Does the wifi-improvements branch change the load the driver puts on
TinyGo's garbage collector, relative to main?

Answer. No. Allocation per request differs by 0.11%, idle allocation is
bit-for-bit identical, and neither build leaks over the measured window.

Date 2026-07-31
Board Seeed XIAO ESP32-C3
Toolchain TinyGo 0.42.0-dev-c2346570, Go 1.27rc2, LLVM 22.1.4
GC gc.conservative, scheduler tasks, unicore
Branch under test wifi-improvements @ fd3dd04
Reference main @ 2e21d40
Harness examples/http-gc (see its README for the procedure)
Load loadgen.sh <ip> 2000 2
Logs /tmp/gc-main.log, /tmp/gc-branch.log

Both runs completed the full 2000-request load (1997 and 1999 connections reached
the server) with no application errors. The single SHA-256 comparison failed line
in each log is the ESP32-C3 ROM bootloader's usual complaint about an unsigned
image and appears identically in both.

1. Allocation per request

The primary figure, because it is independent of how many requests each run
happened to serve. Aggregated over the steady-state full-load samples, excluding
the partial intervals where load was ramping up or down.

main wifi-improvements delta
bytes / request 776.92 777.76 +0.11%
mallocs / request 2.0382 2.0380 −0.01%
requests aggregated 1,727 1,659
implied GC cycle every 58.1 reqs every 58.2 reqs

Both figures are far inside the ~5% run-to-run noise floor that the callsign ring
filling and TCP retry variation produce. At roughly 37 req/s this works out to a
collection about every 1.6 s under load on either build.

2. Idle allocation

This is where the branch's C-to-Go moves — the VHCI ring and parts of lib — were
most likely to show up, since they put the background RX path into Go code that the
collector has to serve.

Every idle sample on both builds reports exactly 152 B / 19 mallocs per 15 s
(≈10 B/s), and both emit exactly one 168 B / 21 malloc sample in the interval
where the load stops. Identical, sample for sample.

Measured over 8 pre-load idle samples on main and 46 post-load idle samples on the
branch.

3. Retained heap and leak check

main wifi-improvements
baseline live (post-warmup, idle) 163,808 B / 140 obj 163,696 B / 139 obj
settled live (post-load, idle) 167,616 B / 174 obj 167,504 B / 173 obj
drift under load +3,808 B / +34 obj +3,808 B / +34 obj

Drift is identical. It is not a leak: it is the worker stacks and connection-pool
state allocated on first use, and it does not grow after.

No leak on either build. The branch held live heap at exactly 167,504 B /
173 obj across 46 consecutive samples — 11.5 minutes of post-load idle, with
zero variation in either figure. main's post-load window is only 3 samples but is
likewise pinned at 167,616 B / 174 obj, and its 8 pre-load idle samples are flat at
164,288 B / 164 obj.

The branch sits 112 B lower in live heap at every point — a constant offset,
consistent with its 96 B cheaper bring-up. One-time, not compounding.

4. Per-phase allocation traces

From the [ALLOC] lines the lneto stack emits at each stack.Debug() site. These
localize the allocation rather than aggregating it, which makes them stronger
evidence than the totals above.

phase main wifi-improvements
post-read-loop 18.00 B (n=999) 18.00 B (n=999)
post-appendhtml 1527.73 B (n=991) 1526.73 B (n=994)
init-complete 130,239 B 130,143 B

Per-request request handling is identical to a fraction of a byte. Bring-up is 96 B
cheaper on the branch.

Conclusion

wifi-improvements can be merged without concern for Go GC impact. Request-path
allocation, idle allocation, and retained-heap drift are all indistinguishable from
main. The branch's costs are a one-time 112 B of live heap, 472 B of static RAM,
and 236 B of heap headroom — all constant, none compounding, none of them changing
how often the collector runs to any degree that matters.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants